Log-Points zur Performancemessung
Performance ist ein komplexes Thema. Häufig ist es schwer überhaupt einen Ansatzpunkt zu finden, wo man mit der Performanceoptimierung beginnen soll. Ich habe ein einfaces Testprogramm geschrieben, um das Problem zu verdeutlichen. Es berechnet in einer Schleife ein Ergebnis mit unterschiedlichen Rechenoperationen.
[notice type=’info’]Der folgende Tipp zeigt in erster Linie, wie man die Log-Points zur Protokollierung einsetzen kann. eine zuverlässige Laufzeitanalyse ist so nicht unbedingt möglich.
Die Transaktion SAT bietet die Möglichkeit, eine definierte Laufzeitmessung durchzuführen. Mittels SET RUN TIME ANALYZER ON/ OFF können explizit Blöcke für die Messung definiert werden. In der Variante kannst du definieren, dass nur diese Blöcke analysiert werden sollen. Zudem kann die Aggregation ausgestellt werden.[/notice]
Testprogramm
Zuerst wird die Tabellen mit Testdaten gefüllt (TESTDATA). Diese Tabelle wird per LOOP durchlaufen und die Berechnung durchgeführt (CALCULATE). Bei Bedarf kann das Ergebnis ausgegeben werden (OUTPUT).
REPORT zzenno38.
CLASS lcl_test DEFINITION.
PUBLIC SECTION.
CLASS-METHODS: main,
output.
PROTECTED SECTION.
TYPES: BEGIN OF ty_data,
type TYPE c LENGTH 1,
count TYPE i,
result TYPE f,
p1 TYPE f,
p2 TYPE f,
END OF ty_data.
CLASS-DATA gt_data TYPE STANDARD TABLE OF ty_data.
CLASS-METHODS:
testdata,
calculate IMPORTING type TYPE char1
count TYPE i
p1 TYPE f
p2 TYPE f
RETURNING VALUE(result) TYPE f .
ENDCLASS.
CLASS lcl_test IMPLEMENTATION.
METHOD testdata.
FIELD-SYMBOLS <data> TYPE ty_data.
APPEND INITIAL LINE TO gt_data ASSIGNING <data>.
<data>-type = 'A'.
<data>-count = 1000.
<data>-p1 = 123.
<data>-p2 = 456.
APPEND INITIAL LINE TO gt_data ASSIGNING <data>.
<data>-type = 'A'.
<data>-count = 10000.
<data>-p1 = 123.
<data>-p2 = 456.
APPEND INITIAL LINE TO gt_data ASSIGNING <data>.
<data>-type = 'A'.
<data>-count = 10000.
<data>-p1 = 123456.
<data>-p2 = 4567890.
APPEND INITIAL LINE TO gt_data ASSIGNING <data>.
<data>-type = 'B'.
<data>-count = 100000.
<data>-p1 = 123.
<data>-p2 = 456.
APPEND INITIAL LINE TO gt_data ASSIGNING <data>.
<data>-type = 'C'.
<data>-count = 10000.
<data>-p1 = 1234567.
<data>-p2 = 4.
ENDMETHOD.
METHOD main.
FIELD-SYMBOLS <data> TYPE ty_data.
testdata( ).
LOOP AT gt_data ASSIGNING <data>.
<data>-result = calculate( type = <data>-type
count = <data>-count
p1 = <data>-p1
p2 = <data>-p2 ).
ENDLOOP.
ENDMETHOD.
METHOD output.
DATA lr_grid TYPE REF TO cl_salv_table.
cl_salv_table=>factory( IMPORTING r_salv_table = lr_grid
CHANGING t_table = gt_data ).
lr_grid->display( ).
ENDMETHOD.
METHOD calculate.
DO count TIMES.
CASE type.
WHEN 'A'.
result = p1 * p2.
WHEN 'B'.
result = p1 / p2.
WHEN 'C'.
result = p1 ** p2.
ENDCASE.
ENDDO.
ENDMETHOD.
ENDCLASS.
PARAMETERS p_output AS CHECKBOX DEFAULT space.
START-OF-SELECTION.
lcl_test=>main( ).
IF p_output = abap_true.
lcl_test=>output( ).
ENDIF.
Auswertung
In der Transaktion SAT erhält man leider zu wenig aussagekräftige Informationen:
Wir brauchen also eine andere Möglichkeit, um die Performance weiter zu analysieren.
Eigene Performanceprotokollierung
Die Protokollierung der Performance ist mit GET RUN TIME möglich. Der Befehl muss jedoch zu Beginn des Tests aufgerufen werden und zum Ende der Messung. Die Zeitendifferenz – also die Laufzeit – muss noch berechnet werden. Das ist umständlich, wenn man mehrere Routinen protokollieren möchte.
Es liegt also nah, diese Funktion auszulagern:
CLASS lcl_performance DEFINITION.
PUBLIC SECTION.
CLASS-METHODS:
start IMPORTING id TYPE any,
stopp IMPORTING id TYPE any.
PROTECTED SECTION.
TYPES: BEGIN OF ty_id_table,
id TYPE string,
count TYPE i,
runtime TYPE i,
END OF ty_id_table.
CLASS-DATA gt_id_table TYPE STANDARD TABLE OF ty_id_table.
ENDCLASS.
CLASS lcl_performance IMPLEMENTATION.
METHOD start.
FIELD-SYMBOLS <id_table> TYPE ty_id_table.
READ TABLE gt_id_table ASSIGNING <id_table> WITH KEY id = id.
IF sy-subrc > 0.
APPEND INITIAL LINE TO gt_id_table ASSIGNING <id_table>.
<id_table>-id = id.
ENDIF.
ADD 1 TO <id_table>-count.
GET RUN TIME FIELD <id_table>-runtime.
ENDMETHOD.
METHOD stopp.
FIELD-SYMBOLS <id_table> TYPE ty_id_table.
DATA lv_runtime TYPE i.
DATA lv_subkey TYPE c LENGTH 200.
READ TABLE gt_id_table ASSIGNING <id_table> WITH KEY id = id.
CHECK sy-subrc = 0.
GET RUN TIME FIELD lv_runtime.
<id_table>-runtime = lv_runtime - <id_table>-runtime.
lv_subkey = |{ id }, Run { <id_table>-count }: { <id_table>-runtime NUMBER = USER }ms|.
LOG-POINT ID z_performance SUBKEY lv_subkey FIELDS <id_table>-runtime.
ENDMETHOD.
ENDCLASS.
Aufruf der Protokollierung
Wir müssen die Methoden unserer Protokollklasse nun nur noch einbinden:
METHOD main.
FIELD-SYMBOLS <data> TYPE ty_data.
testdata( ).
LOOP AT gt_data ASSIGNING <data>.
lcl_performance=>start( <data>-type ).
<data>-result = calculate( type = <data>-type
count = <data>-count
p1 = <data>-p1
p2 = <data>-p2 ).
lcl_performance=>stopp( <data>-type ).
ENDLOOP.
ENDMETHOD.
Log-Points
In dem Coding zur Performanceprotokollierung benutze ich bereits eines Log-Point. Diesen kannst du mit der Transaktion SAAB anlegen. Log-Points haben den Vorteil, dass man diese in jedem System bei Bedarf aktivieren kann. Du benötigst also keine separate Tabelle, um einstellen zu können, was wann protokolliert werden muss, sondern kannst du Standardfunktionalität nutzen.
Mit der Transaktion SAAB musst du den Log-Point auch einschalten. Du kannst wählen, für welchen Zeitraum die Protokollierung aktiv sein soll:
Normalerweise würde man den Log-Point in dieser Form verwenden:
LOG-POINT ID z_performance SUBKEY id FIELDS <id_table>-runtime.
Diese Protokollierung ist jedoch sehr umständlich auszuwerten: Man sieht erstens nur den letzten Aufruf des Log-Points und zweitens muss man die Hierarchie aufklappen.
Aber ich wollte die Auswertung ja einfacher machen. Also machen wir uns den Umstand zunutze, dass die Log-Point-ID bis zu 200 Zeichen lang sein darf und basteln uns für jeden Aufruf eine eigene ID. Das Ergebnis ist viel aussagekräftiger:
Variante
Es ist auch möglich, einem Log-Point eine interne Tabelle zu übergeben! Da jeweils nur der letzte Log-Point gesichert wird, können wir uns diesen Umstand ebenfalls gut zunutze machen:
Wir rufen den Log-Point einfach mit einem festen Wert auf und übergeben bei FIELDS die interne Tabelle:
LOG-POINT ID z_performance SUBKEY 'Default' FIELDS gt_id_table.
Das Ergebnis sieht folgendermaßen aus:
Erweiterungsmöglichkeiten
Die Protokollierung ist natürlich auch noch sehr begrenzt. Du kannst die Methoden jedoch um Parameter erweitern, so dass bei jedem Aufruf zusätzliche Informationen übergeben werden können. Auch könnte die Protokollklasse sich selbst je Log-Id instanziieren, so dass je Log-Id nur die eigenen Aufrufe an den Log-Point übergeben werden. So würde die Messung von mehreren Abschnitten wahrscheinlich übersichtlicher werden.
Doku
Für die genauen Möglichkeiten der Log-Points solltest du dir die Hilfe durchlesen: LOG-POINT.
- 7. December: Excel Racing Simulation – Root Vole Race - 7. Dezember 2024
- 5. December: ABAPConf - 5. Dezember 2024
- 4. December: Only a lazy developer is a good developer - 4. Dezember 2024
